In [1]:
import json
import math
import time
import copy
import random
import numpy as np
import torch
import torch.nn as nn
import torch.optim as optim
from wsbignn import WSBiGNN
import matplotlib.pyplot as plt
from matplotlib import pyplot as plt
torch.autograd.set_detect_anomaly(True)
Out[1]:
<torch.autograd.anomaly_mode.set_detect_anomaly at 0x7f24341bcdc0>
In [2]:
#1. set parameters
#2. visualization
#3. compute the loss
#4. initialize user embeddings
#5. compute adjacency matrix based on mobility and web search
#6. train
#7. compute the Recall and NDCG
#8. main
#9. save

1: set parameters¶

In [3]:
print (torch.cuda.is_available())
device = torch.device("cuda:0")
random_seed = 42
random.seed(random_seed)
torch.manual_seed(random_seed)
torch.cuda.manual_seed(random_seed)
r = random.random
True
In [4]:
x_day, y_day = 2, 1  
case = str(x_day) + "_" + str(y_day)
train_ratio, validate_ratio = 0.70, 0.10
top_k, npr = 3, 5
num_epochs, batch_size, learning_rate = 200, 2, 0.001
hid_dim = 32
hid_dim_cons = 32
hyper_param = {"n_e": num_epochs, "b_s": batch_size, "l_r": learning_rate, "top_k": top_k}
In [5]:
root_path = "/home/umni2/a/umnilab/users/xue120/umni4/2023_web_mobility_summer"+\
                "/1_data_check/data_feature_generation/"
file_name = root_path + "feature_" + str(x_day) + "_" + str(y_day)
train_path = file_name + "/train.json"
vali_path = file_name + "/validate.json"
test_path = file_name + "/test.json"
sampled_user_location_path = file_name + "/sampled_user_location.json"
member_path = root_path + "member/"

2: visualization¶

In [6]:
def visual_train_loss(e_losses):
    plt.figure(figsize=(4,3), dpi=300)
    x = range(len(e_losses))
    y1 = copy.copy(e_losses)
    plt.plot(x,y1, linewidth=1,  label="train")
    plt.legend()
    plt.title('Loss decline on training data')
    plt.xlabel('Epoch')
    plt.ylabel('Loss')
    plt.savefig(case + '/' + 'train_loss.png',bbox_inches = 'tight')
    plt.show()
    
def visual_vali_test_loss(recall_vali, recall_test, ndcg_vali, ndcg_test):
    plt.figure(figsize=(4,3), dpi=300)
    x = range(len(recall_vali))    
    plt.plot(x, recall_vali, linewidth=1, label="Recall_validate")
    plt.plot(x, ndcg_vali, linewidth=1, label="NDCG_validate")
    plt.plot(x, recall_test, linewidth=1, label="Recall_test")
    plt.plot(x, ndcg_test, linewidth=1, label="NDCG_test")
    plt.legend()
    plt.title('Recall/NDCG on validate/test sets')
    plt.xlabel('Epoch')
    plt.ylabel('Recall@3, NDCG@3')
    plt.savefig(case + '/' + 'vali_test_recall_ndcg.png',bbox_inches = 'tight')
    plt.show()

3: compute the loss¶

In [7]:
#compute the cross entropy loss
#input1:  gnn_output   dim = (batch, y_day, U, V).
#input2:  real_link    dim = (batch, y_day, n_edge, 2).
#input3:  criterion
#inputs 4,5,6:  n_user, n_loc, npr
#output: average loss for batch*y_day terms
def compute_loss(gnn_output, real_link, criterion, n_user, n_loc, npr):
    batch, y_day = gnn_output.size()[0], gnn_output.size()[1]
    loss = torch.tensor([0.0])
    all_edge = [str(u)+"_"+str(v) for u in range(n_user) for v in range(n_loc)]
    
    for i in range(batch):
        for j in range(y_day):
            predicted, real = gnn_output[i][j], real_link[i][j] 
            #positive edges
            str_real = [str(int(real[k][0])) + "_" + str(int(real[k][1])) for k in range(len(real))]
            num_real = len(real) - str_real.count(str(-1)+"_"+str(-1))
            set_pos = set(str_real[0: num_real])
            all_pos = list(set_pos)
            n_pos = len(all_pos)
            
            #sample negative edges
            all_neg = list(set(all_edge) - set_pos)
            n_sampled_neg = int(n_pos * npr)
            sampled_neg = random.sample(all_neg, n_sampled_neg)
            
            #prepare for loss computing
            pos = [[int(item.split("_")[0]), int(item.split("_")[1])] for item in all_pos] 
            neg = [[int(item.split("_")[0]), int(item.split("_")[1])] for item in sampled_neg] 
            pos_idx = [pos[k][0]*n_loc + pos[k][1] for k in range(n_pos)]
            neg_idx = [neg[k][0]*n_loc + neg[k][1] for k in range(n_sampled_neg)]
            hat_1_pos = torch.take(predicted, torch.tensor(pos_idx)) 
            hat_1_neg = torch.take(predicted, torch.tensor(neg_idx))
            hat_1 = torch.sigmoid(torch.cat((hat_1_pos, hat_1_neg)).unsqueeze(dim=0))  
            hat = torch.log(torch.transpose(torch.cat((1.0-hat_1, hat_1), dim=0),1,0))  #NLLLOSS
            
            real = torch.tensor([1]*n_pos + [0]*n_sampled_neg)
            loss += criterion(hat, real)
    loss = loss*1.0/(batch*y_day)
    return loss

4: initialize user embeddings¶

In [8]:
#define user embeddings based on POI embeddings.
#input1: x_loc             dim = (V, 200)
#input2: x_mob_batch      dim = (batch, x_day, n_m, 2)
#input3: x_text_batch         dim = (batch, x_day, n_t, 2)
#input4: n_user         
#output: x_user                dim = (batch, U, 200)
def compute_user_embedding(x_loc, x_mob_batch, x_text_batch, n_user):
    x_user = torch.zeros((0, n_user, 200), device=device)
    x_m_t_batch = torch.cat([x_mob_batch, x_text_batch], dim=2)  #dim = (batch, x_day, n_m+n_t, 2)
    batch = x_m_t_batch.size()[0]
    
    for i in range(batch):
        #initialize 
        user_sum_embed = torch.zeros((n_user, 200), device=device)
        user_ave_embed = torch.zeros((n_user, 200), device=device)
        user_count_embed, user_with_edge = [0]*n_user, list()

        #update user embeddings
        link_record = x_m_t_batch[i][0]  #extract the first day
        for link in link_record:
            if link[0] != -1:
                user, loc = link[0], link[1] 
                user_with_edge.append(user)              
                user_count_embed[user] = user_count_embed[user] + 1     
                user_sum_embed[user] = user_sum_embed[user] + x_loc[loc]
            else:
                break
                
        set_user_with_edge = set(user_with_edge)
        for user in set_user_with_edge:
            user_ave_embed[user] = user_sum_embed[user]/user_count_embed[user]
        
        #update the user embedding for other users with mobility records on the first day
        #compute the average embedding  
        n_user_with_edge = len(set_user_with_edge)
        ave_embedding = torch.sum(user_ave_embed, dim=0)/(1.0*n_user_with_edge)
        
        #define the embeddings for remaining users as the average embedding 
        set_remain = set(range(n_user))-set_user_with_edge
        dict_remain = {user:0 for user in set_remain}
        for user in dict_remain:
            user_ave_embed[user] = ave_embedding
        
        #concatenate different batches
        x_user = torch.cat([x_user, user_ave_embed.unsqueeze(0)],dim=0)
    return x_user                                        

5: compute adjacency matrix based on mobility and web search¶

In [9]:
#input1: x_mob_batch       dim = (batch, x_day, n_m, 2)
#input2: x_text_batch      dim = (batch, x_day, n_t, 2)
#inputs3,4: u_user, n_loc
#output1: x_adj            dim = (batch, x_day, n_user+2*n_loc, n_user+2*n_loc)
def convert_to_adj(x_mob_batch, x_text_batch, n_user, n_loc):
    time_1 = time.time()
    batch, x_day = x_mob_batch.size()[0], x_mob_batch.size()[1]
    adj_dim = n_user + 2*n_loc
    adj = torch.zeros((batch, x_day, adj_dim, adj_dim), device=device)
    
    for i in range(batch):
        x_mob_record, x_text_record = x_mob_batch[i], x_text_batch[i]
        for j in range(x_day):
            x_mob_one_day, x_text_one_day = x_mob_record[j], x_text_record[j]
            #extract mob edges
            for link in x_mob_one_day:
                if link[0] != -1:
                    user, loc = link[0], link[1]
                    n_idx = n_user + loc
                    adj[i][j][user][n_idx] = adj[i][j][user][n_idx] + 1 
                    adj[i][j][n_idx][user] = adj[i][j][user][n_idx]
                else:
                    break
            
            #extract text edges
            for link in x_text_one_day:
                if link[0] != -1:
                    user, loc = link[0], link[1] 
                    n_idx = n_user + n_loc + loc
                    adj[i][j][user][n_idx] = adj[i][j][user][n_idx] + 1
                    adj[i][j][n_idx][user] = adj[i][j][user][n_idx]
                else:
                    break
    return adj

6: train¶

In [10]:
#6.1: one training epoch   
#output: the average loss, model         
def train_epoch(model, opt, criterion, train, hyper_param_dict, y_day, npr, loss_batch_all):
    time_1 = time.time()
    model.train()
    losses = list()
    
    n_user, n_loc, b_s = hyper_param["n_user"], hyper_param["n_loc"], hyper_param["b_s"]
    x_u_v, x_poi, train_x_mob, train_x_text, train_y_mob =\
        train["u_v"].to(device), train["x_poi"].to(device), train["x_mob"],\
            train["x_text"], train["y_mob"]
    n = train_x_mob.size()[0] 
    print ("# batch: ", int(n/b_s))
    
    for i in range(0, n-b_s, b_s):
        time_1 = time.time()          
        x_mob_batch, x_text_batch, y_mob_batch = train_x_mob[i:i + b_s], train_x_text[i:i + b_s], train_y_mob[i:i + b_s]    
    
        opt.zero_grad()
        
        loss = torch.zeros(1, dtype=torch.float)
        x_user = compute_user_embedding(x_poi, x_mob_batch, x_text_batch, n_user)  #4.
        
        x_adj = convert_to_adj(x_mob_batch, x_text_batch, n_user, n_loc)                  #5. 
        
        model_output = model.run(x_u_v, x_poi, x_user.to(device), x_adj.to(device), b_s) 
        
        loss = compute_loss(model_output.cpu(), y_mob_batch, criterion, n_user, n_loc, npr)  #3.
        loss_batch_all.append(loss.data.numpy()[0])
        loss.backward()
        opt.step()
        losses.append(loss.data.numpy())  # sum over batches
        
        time2 = time.time()
        if i%20 == 0:
            print ("i_batch: ", i/b_s)
            print ("the loss is: ", loss.data.numpy()[0])
            print ("time for this batch: ", round(time2 - time_1,3))
            print ("-----------------a batch ends---------------")
    return sum(losses)/float(len(losses)+0.000001), model, loss_batch_all
In [11]:
#6.2
def train_process(train, vali, test, net, criterion, hyper_param, y_day, loss_batch_all):   
    e_losses_train = list()
    recall_vali, recall_test, ndcg_vali, ndcg_test = list(), list(), list(), list()
    l_r, n_e, b_s  = hyper_param["l_r"], hyper_param["n_e"], hyper_param["b_s"]

    opt = optim.Adam(net.parameters(), l_r, betas = (0.9,0.999), weight_decay = 0.0001)
    opt_scheduler = torch.optim.lr_scheduler.MultiStepLR(opt, milestones=[150]) 
    print ("# epochs: ", n_e)
    print ("------------------------------------------------------------")        
    time_start = time.time()
    no_improve_in_n = 0
    
    #prepare for vali and test
    print ("start preparing for vali and test")
    vali_u_v, vali_x_poi, vali_x_user, vali_x_adj, vali_y_real = prepare_validate_test(vali, hyper_param)
    print ("finish vali")
    test_u_v, test_x_poi, test_x_user, test_x_adj, test_y_real = prepare_validate_test(test, hyper_param)
    print ("finish test")
           
    for i in range(n_e):
        print ("i_epoch: ", i)
        print ("----------------an epoch starts-------------------")
        time1 = time.time()
        n_train = len(train["x_mob"])
        number_list = copy.copy(list(range(n_train)))
        random.shuffle(number_list, random = r)
        shuffle_idx = torch.tensor(number_list)
        
        #train one epoch
        train_shuffle = dict()
        train_shuffle["u_v"] = train["u_v"]
        train_shuffle["x_poi"], train_shuffle["x_mob"] = train["x_poi"], train["x_mob"][shuffle_idx]
        train_shuffle["x_text"], train_shuffle["y_mob"] = train["x_text"][shuffle_idx], train["y_mob"][shuffle_idx]
        
        loss, net, loss_batch_all =  train_epoch(net, opt, criterion, train_shuffle, hyper_param, y_day, npr, loss_batch_all)
        
        opt_scheduler.step() 
        
        loss = float(loss)
        print ("train loss for this epoch: ", round(loss, 6))
        e_losses_train.append(loss)
        visual_train_loss(e_losses_train)
        
        print ("----------------validate-------------------")
        val_all_recall, val_all_ndcg, val_ave_recall, val_ave_ndcg =\
                validate_test(net, hyper_param, \
                              vali_u_v, vali_x_poi, vali_x_user, vali_x_adj, vali_y_real, False)
        
        print ("----------------test-------------------")
        test_all_recall, test_all_ndcg, test_ave_recall, test_ave_ndcg =\
               validate_test(net, hyper_param,\
                             test_u_v, test_x_poi, test_x_user, test_x_adj, test_y_real, False)
        
        if len(recall_vali) > 0:
            past_max = np.max(recall_vali)
        else:
            past_max = 0.0
        recall_vali.append(val_ave_recall)
        recall_test.append(test_ave_recall)
        ndcg_vali.append(val_ave_ndcg)
        ndcg_test.append(test_ave_ndcg)
        visual_vali_test_loss(recall_vali, recall_test, ndcg_vali, ndcg_test)
        
        #store
        performance = {"recall_val": recall_vali, "recall_test": recall_test, \
                       "ndcg_val": ndcg_vali,"ndcg_test": ndcg_test,\
                        "e_losses_train": e_losses_train}
        subfile =  open(case + '/' + 'performance'+'.json','w')
        json.dump(performance, subfile)
        subfile.close()
                    
        #early stop
        if val_ave_recall < past_max:
            no_improve_in_n = no_improve_in_n + 1
        else:
            no_improve_in_n = 0
        if no_improve_in_n == 30:
            print ("Early stop at the " + str(i+1) + "-th epoch")
            return e_losses_train, net, loss_batch_all
        time2 = time.time()
        print ("running time for this epoch: ", time2 - time1)
        time_now = time.time()
        print ("running time until now: ", time_now - time_start)
        print ("-------------------------an epoch ends ---------------------------")
    return e_losses_train, net, loss_batch_all
In [12]:
#6.3
def model_train(train, vali, test, hyper_param, x_day, y_day, member):
    with torch.autograd.set_detect_anomaly(True):       
        loss_batch_all = list()
        model = WSBiGNN(hid_dim, hid_dim_cons, x_day, member).to(device)          
        criterion = nn.NLLLoss() 
        print ("start train_process")
        e_losses, trained_model, loss_batch_all = train_process(train, vali, test, model,\
                                                criterion, hyper_param, y_day, loss_batch_all)  
        return e_losses, trained_model, loss_batch_all

7: compute the Recall and NDCG¶

In [13]:
#7.1: compute Recall@K, NDCG@K
#input1:  gnn_output   dim = (batch, y_day, U, V)
#input2:  real_link    dim = (batch, y_day, n_edge, 2)
#inputs3,4:  n_user, n_loc
#input5: top_k
#output: Recall@K, NDCG@K
def compute_recall_ndcg(gnn_output, real_link, n_user, n_loc, top_k):
    batch, y_day = gnn_output.size()[0], gnn_output.size()[1]
    recall_all = [[0.0 for j in range(y_day)] for i in range(batch)] 
    ndcg_all = [[0.0 for j in range(y_day)] for i in range(batch)] 
    
    for i in range(batch):
        for j in range(y_day):
            recall_user, ndcg_user = {}, {}
            predicted, real = gnn_output[i][j].tolist(), real_link[i][j] 
            
            #1. construct the real mobility
            real_list, real_dict = {user: [] for user in range(n_user)}, {user: {} for user in range(n_user)}
            for k in range(len(real)):
                edge = real[k]
                user, poi = int(edge[0]), int(edge[1])
                if user > -1:
                    real_list[user].append(poi)
                else:
                    break
            for user in real_list:
                real_dict[user] = set(real_list[user])
            
            #2. compute Recall@K, NDCG@K
            for user in real_dict:
                real_poi = real_dict[user]
                len_real_poi = len(real_poi)
                if len_real_poi > 0:
                    predict_row = predicted[user]                 #[0,0,12,1,5]
                    largest_k_idx = np.argsort(predict_row)[::-1] #[2,4,3,1,0]
                    top_k_idx = largest_k_idx[0: top_k]            #[2,4,3]
                    
                    #compute Recall
                    predict_top_k = set(top_k_idx)
                    recall_user[user] = len(predict_top_k.intersection(real_poi))*1.0/len_real_poi
                    
                    #compute NDCG
                    weight = [1.0/(math.log(k+2)/math.log(2.0)) for k in range(top_k)]
                    #denominator
                    if len_real_poi < top_k:
                         best_rank = [1.0]*len_real_poi + [0.0]*(top_k-len_real_poi)
                    else:
                         best_rank = [1.0]*top_k        
                    #numerator  
                    predict_rank = [0.0]* top_k
                    for idx in range(len(top_k_idx)):
                        if top_k_idx[idx] in real_poi:
                            predict_rank[idx] = 1.0
                    #NDCG
                    ndcg_user[user] = float(np.dot(weight, predict_rank)/np.dot(weight, best_rank))
            
            #3. compute the average Recall@k, average NDCG@k.
            recall_all[i][j] = float(np.mean(list(recall_user.values())))
            ndcg_all[i][j] = float(np.mean(list(ndcg_user.values())))
    ave_recall, ave_ndcg = np.mean(recall_all), np.mean(ndcg_all)
    print ("ave Recall", ave_recall)
    print ("ave NDCG", ave_ndcg)
    return recall_all, ndcg_all, ave_recall, ave_ndcg

#7.2: evaluate the trained model on validation or test 
def prepare_validate_test(vali_test, hyper_param):
    n_user, n_loc = hyper_param["n_user"], hyper_param["n_loc"]
    u_v, x_poi, x_mob, x_text, y_real =\
        vali_test["u_v"].to(device), vali_test["x_poi"].to(device), vali_test["x_mob"].to(device), \
            vali_test["x_text"].to(device), vali_test["y_mob"]
    x_user = compute_user_embedding(x_poi, x_mob, x_text, n_user)
    x_adj = convert_to_adj(x_mob, x_text, n_user, n_loc)
    return u_v, x_poi, x_user, x_adj, y_real

def validate_test(trained_model, hyper_param, u_v, x_poi, x_user, x_adj, y_real, output=False):  
    n_user, n_loc = hyper_param["n_user"], hyper_param["n_loc"]
    top_k, b_s = hyper_param["top_k"], y_real.size()[0]
    
    y_hat = trained_model.run(u_v, x_poi, x_user, x_adj, b_s)
    all_recall, all_ndcg, ave_recall, ave_ndcg =\
        compute_recall_ndcg(y_hat.cpu(), y_real, n_user, n_loc, top_k)
    
    if output == True:
        return all_recall, all_ndcg, ave_recall, ave_ndcg, y_hat.cpu(), y_real
    else:
        return all_recall, all_ndcg, ave_recall, ave_ndcg

8: train¶

In [14]:
#8.1: tensorize
def tensorize(train_vali_test):
    result = dict()
    result["u_v"] = torch.tensor(train_vali_test["u_v"]) 
    result["x_poi"] = torch.tensor(train_vali_test["x_poi"])     
    result["x_mob"] = torch.tensor(train_vali_test["x_mob"]) 
    result["x_text"] = torch.tensor(train_vali_test["x_text"]) 
    result["y_mob"] = torch.tensor(train_vali_test["y_mob"]) 
    return result
In [15]:
#8.2: load the data
train = tensorize(json.load(open(train_path)))
vali = tensorize(json.load(open(vali_path)))
test = tensorize(json.load(open(test_path)))
sampled_user_location = json.load(open(sampled_user_location_path))
sampled_user_location["n_user"] = len(sampled_user_location["u"])
sampled_user_location["n_loc"] = len(sampled_user_location["p"])

u_list, p_list = sampled_user_location["u"], sampled_user_location["p"]
hyper_param["n_user"], hyper_param["n_loc"] = len(u_list), len(p_list)

#supernode
member_dict = json.load(open(member_path + "member_" + case + ".json"))
#sg, s_ng, ns_g, ns_ng
member = torch.tensor([member_dict["s_g"], member_dict["s_ng"],\
                       member_dict["ns_g"], member_dict["ns_ng"]], device=device)
In [16]:
#8.3: model 
e_losses, trained_model, loss_batch_all = model_train(train, vali, test, hyper_param,\
                                                      x_day, y_day, member)
start train_process
# epochs:  200
------------------------------------------------------------
start preparing for vali and test
finish vali
finish test
i_epoch:  0
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  6.4177284
time for this batch:  1.424
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  3.3050778
time for this batch:  0.516
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  2.1313083
time for this batch:  0.673
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  1.5316395
time for this batch:  0.615
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  1.2788055
time for this batch:  0.603
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  1.1321309
time for this batch:  0.674
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  1.0364242
time for this batch:  0.624
-----------------a batch ends---------------
train loss for this epoch:  2.114359
----------------validate-------------------
ave Recall 0.033313679444210154
ave NDCG 0.02137636828424351
----------------test-------------------
ave Recall 0.0333442599426068
ave NDCG 0.021584574425886478
running time for this epoch:  45.96461200714111
running time until now:  112.03449845314026
-------------------------an epoch ends ---------------------------
i_epoch:  1
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  1.0140365
time for this batch:  0.598
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.94442356
time for this batch:  0.583
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.88060176
time for this batch:  0.735
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.82419336
time for this batch:  0.667
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.77336776
time for this batch:  0.838
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.7362854
time for this batch:  0.665
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.7011421
time for this batch:  0.618
-----------------a batch ends---------------
train loss for this epoch:  0.830455
----------------validate-------------------
ave Recall 0.027958912872692736
ave NDCG 0.018635083104063175
----------------test-------------------
ave Recall 0.020574651212429625
ave NDCG 0.014077764566756341
running time for this epoch:  44.02361035346985
running time until now:  156.05815172195435
-------------------------an epoch ends ---------------------------
i_epoch:  2
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.68842226
time for this batch:  0.641
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.6581179
time for this batch:  0.572
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.6279676
time for this batch:  0.701
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.5971478
time for this batch:  0.637
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.5685109
time for this batch:  0.687
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.5362077
time for this batch:  0.674
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.5007755
time for this batch:  0.649
-----------------a batch ends---------------
train loss for this epoch:  0.593323
----------------validate-------------------
ave Recall 0.2040617999449693
ave NDCG 0.16822734865408137
----------------test-------------------
ave Recall 0.19015905312678374
ave NDCG 0.16364522024102532
running time for this epoch:  44.89993715286255
running time until now:  200.95813250541687
-------------------------an epoch ends ---------------------------
i_epoch:  3
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.49283272
time for this batch:  0.562
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.45744616
time for this batch:  0.638
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.42692876
time for this batch:  0.575
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.40233722
time for this batch:  0.651
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.37789288
time for this batch:  0.715
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.3726231
time for this batch:  0.518
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.33572266
time for this batch:  0.629
-----------------a batch ends---------------
train loss for this epoch:  0.407381
----------------validate-------------------
ave Recall 0.3699532175225164
ave NDCG 0.31116127506721003
----------------test-------------------
ave Recall 0.3503056202809096
ave NDCG 0.2873993750576572
running time for this epoch:  44.415034532547
running time until now:  245.37320971488953
-------------------------an epoch ends ---------------------------
i_epoch:  4
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.33845127
time for this batch:  0.588
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.3185029
time for this batch:  0.617
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.29371473
time for this batch:  0.624
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.29229072
time for this batch:  0.538
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.27954978
time for this batch:  0.579
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.28519252
time for this batch:  0.649
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.27688396
time for this batch:  0.698
-----------------a batch ends---------------
train loss for this epoch:  0.29847
----------------validate-------------------
ave Recall 0.46432355938394715
ave NDCG 0.39808969222119805
----------------test-------------------
ave Recall 0.4295440114116984
ave NDCG 0.3635223993123925
running time for this epoch:  44.59915781021118
running time until now:  289.97241163253784
-------------------------an epoch ends ---------------------------
i_epoch:  5
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.28452206
time for this batch:  0.589
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.24866077
time for this batch:  0.611
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.25238448
time for this batch:  0.624
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.23474509
time for this batch:  0.708
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.26218796
time for this batch:  0.724
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.24543712
time for this batch:  0.759
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.23664618
time for this batch:  0.683
-----------------a batch ends---------------
train loss for this epoch:  0.248584
----------------validate-------------------
ave Recall 0.5595363737590264
ave NDCG 0.4795623254820501
----------------test-------------------
ave Recall 0.5275446044002178
ave NDCG 0.4456916640154201
running time for this epoch:  46.930270195007324
running time until now:  336.90272426605225
-------------------------an epoch ends ---------------------------
i_epoch:  6
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.23328446
time for this batch:  0.532
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.24305612
time for this batch:  0.645
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.20398813
time for this batch:  0.625
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.2187061
time for this batch:  0.679
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.20611235
time for this batch:  0.614
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.19633535
time for this batch:  0.75
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.23162398
time for this batch:  0.529
-----------------a batch ends---------------
train loss for this epoch:  0.220419
----------------validate-------------------
ave Recall 0.6114185050588199
ave NDCG 0.5245365605200737
----------------test-------------------
ave Recall 0.5867773255661507
ave NDCG 0.4931023420033181
running time for this epoch:  45.73157978057861
running time until now:  382.6343550682068
-------------------------an epoch ends ---------------------------
i_epoch:  7
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.22031733
time for this batch:  0.541
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.18710382
time for this batch:  0.674
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.20308675
time for this batch:  0.677
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.19776624
time for this batch:  0.68
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.19930732
time for this batch:  0.723
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.21399343
time for this batch:  0.634
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.20121226
time for this batch:  0.716
-----------------a batch ends---------------
train loss for this epoch:  0.201332
----------------validate-------------------
ave Recall 0.6405636110849996
ave NDCG 0.5482197180737127
----------------test-------------------
ave Recall 0.6173932293646298
ave NDCG 0.5218382383939506
running time for this epoch:  45.46600675582886
running time until now:  428.10041403770447
-------------------------an epoch ends ---------------------------
i_epoch:  8
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.17422247
time for this batch:  0.548
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.18857777
time for this batch:  0.583
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.19288161
time for this batch:  0.704
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.18364632
time for this batch:  0.685
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.19008905
time for this batch:  0.65
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.18363427
time for this batch:  0.592
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.1919142
time for this batch:  0.609
-----------------a batch ends---------------
train loss for this epoch:  0.189953
----------------validate-------------------
ave Recall 0.649330792964053
ave NDCG 0.5576094419238545
----------------test-------------------
ave Recall 0.6314537386520132
ave NDCG 0.5298453648420192
running time for this epoch:  44.636006355285645
running time until now:  472.73646545410156
-------------------------an epoch ends ---------------------------
i_epoch:  9
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.168859
time for this batch:  0.656
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.1764947
time for this batch:  0.745
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.18279892
time for this batch:  0.652
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.16710919
time for this batch:  0.714
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.17442343
time for this batch:  0.684
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.19327675
time for this batch:  0.735
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.185752
time for this batch:  0.609
-----------------a batch ends---------------
train loss for this epoch:  0.180318
----------------validate-------------------
ave Recall 0.6517134623595716
ave NDCG 0.5607246564562259
----------------test-------------------
ave Recall 0.6388116946247575
ave NDCG 0.5338515782336856
running time for this epoch:  46.15280485153198
running time until now:  518.8893208503723
-------------------------an epoch ends ---------------------------
i_epoch:  10
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.17813736
time for this batch:  0.577
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.1884121
time for this batch:  0.679
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.16369146
time for this batch:  0.601
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.15712598
time for this batch:  0.655
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.2034846
time for this batch:  0.649
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.16934642
time for this batch:  0.625
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.17855977
time for this batch:  0.675
-----------------a batch ends---------------
train loss for this epoch:  0.173259
----------------validate-------------------
ave Recall 0.6531048877030063
ave NDCG 0.5609323349353402
----------------test-------------------
ave Recall 0.6364682203913543
ave NDCG 0.5373531905699275
running time for this epoch:  45.05411624908447
running time until now:  563.9434833526611
-------------------------an epoch ends ---------------------------
i_epoch:  11
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.17844443
time for this batch:  0.671
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.16578414
time for this batch:  0.595
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.16341367
time for this batch:  0.784
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.16262335
time for this batch:  0.649
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.18200576
time for this batch:  0.513
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.18461463
time for this batch:  0.705
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.17381358
time for this batch:  0.653
-----------------a batch ends---------------
train loss for this epoch:  0.170359
----------------validate-------------------
ave Recall 0.6557149581987136
ave NDCG 0.5638434798728424
----------------test-------------------
ave Recall 0.6435362720163162
ave NDCG 0.5413007446273268
running time for this epoch:  43.32778549194336
running time until now:  607.2713119983673
-------------------------an epoch ends ---------------------------
i_epoch:  12
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.15608484
time for this batch:  0.627
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.15821102
time for this batch:  0.671
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.15068357
time for this batch:  0.75
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.16092753
time for this batch:  0.7
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.18031794
time for this batch:  0.705
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.15723038
time for this batch:  0.571
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15958738
time for this batch:  0.697
-----------------a batch ends---------------
train loss for this epoch:  0.166537
----------------validate-------------------
ave Recall 0.6633527966980824
ave NDCG 0.5664007665088214
----------------test-------------------
ave Recall 0.6491497167343185
ave NDCG 0.5456708354567283
running time for this epoch:  45.77895259857178
running time until now:  653.0503208637238
-------------------------an epoch ends ---------------------------
i_epoch:  13
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.17426717
time for this batch:  0.689
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.15326552
time for this batch:  0.668
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.16449139
time for this batch:  0.569
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.18007514
time for this batch:  0.542
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.15230648
time for this batch:  0.548
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.154695
time for this batch:  0.568
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.16576216
time for this batch:  0.584
-----------------a batch ends---------------
train loss for this epoch:  0.161883
----------------validate-------------------
ave Recall 0.6648102661140358
ave NDCG 0.5656626577205015
----------------test-------------------
ave Recall 0.6510704706539481
ave NDCG 0.5473673884890148
running time for this epoch:  44.635886669158936
running time until now:  697.6862497329712
-------------------------an epoch ends ---------------------------
i_epoch:  14
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.157148
time for this batch:  0.596
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.15204102
time for this batch:  0.608
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.15150908
time for this batch:  0.655
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14710353
time for this batch:  0.615
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.16995479
time for this batch:  0.627
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.1534054
time for this batch:  0.83
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15083909
time for this batch:  0.63
-----------------a batch ends---------------
train loss for this epoch:  0.16032
----------------validate-------------------
ave Recall 0.6633393225857493
ave NDCG 0.56840128462982
----------------test-------------------
ave Recall 0.6494393188856611
ave NDCG 0.5492121487935058
running time for this epoch:  44.70862317085266
running time until now:  742.3949148654938
-------------------------an epoch ends ---------------------------
i_epoch:  15
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.14870323
time for this batch:  0.716
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14585894
time for this batch:  0.669
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.15377033
time for this batch:  0.775
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.15169391
time for this batch:  0.76
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.16207765
time for this batch:  0.677
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.17151347
time for this batch:  0.659
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15488854
time for this batch:  0.61
-----------------a batch ends---------------
train loss for this epoch:  0.159819
----------------validate-------------------
ave Recall 0.6661779654171505
ave NDCG 0.5660264180344556
----------------test-------------------
ave Recall 0.6487406724302585
ave NDCG 0.5449698770218673
running time for this epoch:  47.937220335006714
running time until now:  790.3321778774261
-------------------------an epoch ends ---------------------------
i_epoch:  16
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.16359371
time for this batch:  0.462
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14380318
time for this batch:  0.709
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.15894815
time for this batch:  0.693
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.15488747
time for this batch:  0.677
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.17259297
time for this batch:  0.562
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.15819058
time for this batch:  0.593
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.17383818
time for this batch:  0.625
-----------------a batch ends---------------
train loss for this epoch:  0.156294
----------------validate-------------------
ave Recall 0.6683850752819605
ave NDCG 0.5665134480624991
----------------test-------------------
ave Recall 0.6520586414340409
ave NDCG 0.5465115008066979
running time for this epoch:  44.4361515045166
running time until now:  834.7683761119843
-------------------------an epoch ends ---------------------------
i_epoch:  17
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.159408
time for this batch:  0.614
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.16541252
time for this batch:  0.57
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.15991321
time for this batch:  0.541
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.15757215
time for this batch:  0.625
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14190942
time for this batch:  0.785
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.15583988
time for this batch:  0.75
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15377894
time for this batch:  0.783
-----------------a batch ends---------------
train loss for this epoch:  0.153812
----------------validate-------------------
ave Recall 0.6613302007749975
ave NDCG 0.5626874481659492
----------------test-------------------
ave Recall 0.6560217441253093
ave NDCG 0.5490123432174205
running time for this epoch:  46.611812353134155
running time until now:  881.3802306652069
-------------------------an epoch ends ---------------------------
i_epoch:  18
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12849107
time for this batch:  0.739
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.1334334
time for this batch:  0.659
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14585455
time for this batch:  0.627
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.16128707
time for this batch:  0.661
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.1600635
time for this batch:  0.62
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14265028
time for this batch:  0.595
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15745693
time for this batch:  0.809
-----------------a batch ends---------------
train loss for this epoch:  0.151267
----------------validate-------------------
ave Recall 0.6647605179505576
ave NDCG 0.5632385995232511
----------------test-------------------
ave Recall 0.6515731433327532
ave NDCG 0.5448249028744839
running time for this epoch:  44.701838970184326
running time until now:  926.0821096897125
-------------------------an epoch ends ---------------------------
i_epoch:  19
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.14604694
time for this batch:  0.555
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14408651
time for this batch:  0.674
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14647755
time for this batch:  0.541
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14470062
time for this batch:  0.702
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14619696
time for this batch:  0.634
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.15782744
time for this batch:  0.628
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14423095
time for this batch:  0.641
-----------------a batch ends---------------
train loss for this epoch:  0.150879
----------------validate-------------------
ave Recall 0.6670454377523138
ave NDCG 0.5647971323790613
----------------test-------------------
ave Recall 0.6592333073643692
ave NDCG 0.5506839628208522
running time for this epoch:  43.965572118759155
running time until now:  970.0477271080017
-------------------------an epoch ends ---------------------------
i_epoch:  20
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.14615908
time for this batch:  0.564
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13779971
time for this batch:  0.677
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14454146
time for this batch:  0.671
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14672148
time for this batch:  0.645
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.15670186
time for this batch:  0.587
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14939243
time for this batch:  0.586
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15356086
time for this batch:  0.71
-----------------a batch ends---------------
train loss for this epoch:  0.148465
----------------validate-------------------
ave Recall 0.669105192357554
ave NDCG 0.5673076376763608
----------------test-------------------
ave Recall 0.6519354089886009
ave NDCG 0.5440557231106742
running time for this epoch:  43.99763512611389
running time until now:  1014.0454065799713
-------------------------an epoch ends ---------------------------
i_epoch:  21
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.14254496
time for this batch:  0.5
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.15573774
time for this batch:  0.626
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14342621
time for this batch:  0.646
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.16625914
time for this batch:  0.744
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13465962
time for this batch:  0.594
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.15500465
time for this batch:  0.629
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.16885805
time for this batch:  0.703
-----------------a batch ends---------------
train loss for this epoch:  0.148909
----------------validate-------------------
ave Recall 0.6658906898361725
ave NDCG 0.5649731518711671
----------------test-------------------
ave Recall 0.6590925524043909
ave NDCG 0.5493886582056142
running time for this epoch:  43.55287194252014
running time until now:  1057.598332643509
-------------------------an epoch ends ---------------------------
i_epoch:  22
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13838068
time for this batch:  0.587
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14535552
time for this batch:  0.539
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.15058747
time for this batch:  0.676
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.13860789
time for this batch:  0.687
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.1484802
time for this batch:  0.804
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.16110086
time for this batch:  0.679
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.13862357
time for this batch:  0.843
-----------------a batch ends---------------
train loss for this epoch:  0.147338
----------------validate-------------------
ave Recall 0.6662435081122134
ave NDCG 0.5672765930557653
----------------test-------------------
ave Recall 0.6574630082986394
ave NDCG 0.549313053030215
running time for this epoch:  47.70711088180542
running time until now:  1105.3054881095886
-------------------------an epoch ends ---------------------------
i_epoch:  23
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.14700687
time for this batch:  0.627
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14269844
time for this batch:  0.59
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13544273
time for this batch:  0.65
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.1328462
time for this batch:  0.669
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14646661
time for this batch:  0.606
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14731416
time for this batch:  0.695
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15284824
time for this batch:  0.646
-----------------a batch ends---------------
train loss for this epoch:  0.145572
----------------validate-------------------
ave Recall 0.6641710633892097
ave NDCG 0.5670073291744175
----------------test-------------------
ave Recall 0.6559942115148503
ave NDCG 0.5509341767312259
running time for this epoch:  43.897863149642944
running time until now:  1149.2033958435059
-------------------------an epoch ends ---------------------------
i_epoch:  24
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12912539
time for this batch:  0.669
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14698565
time for this batch:  0.566
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13250278
time for this batch:  0.47
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14049882
time for this batch:  0.561
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14958328
time for this batch:  0.544
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13912499
time for this batch:  0.505
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14619955
time for this batch:  0.63
-----------------a batch ends---------------
train loss for this epoch:  0.144683
----------------validate-------------------
ave Recall 0.6612494197174268
ave NDCG 0.5654896826532425
----------------test-------------------
ave Recall 0.6505135965092248
ave NDCG 0.5490944576064943
running time for this epoch:  40.759867906570435
running time until now:  1189.963305234909
-------------------------an epoch ends ---------------------------
i_epoch:  25
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.14688858
time for this batch:  0.482
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.15065245
time for this batch:  0.54
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.15093452
time for this batch:  0.56
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14855355
time for this batch:  0.63
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13243261
time for this batch:  0.682
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14256056
time for this batch:  0.481
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.1407431
time for this batch:  0.507
-----------------a batch ends---------------
train loss for this epoch:  0.143632
----------------validate-------------------
ave Recall 0.6577834940497961
ave NDCG 0.561862219853356
----------------test-------------------
ave Recall 0.6560738717362328
ave NDCG 0.5487672462786904
running time for this epoch:  40.15753197669983
running time until now:  1230.1208946704865
-------------------------an epoch ends ---------------------------
i_epoch:  26
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13385394
time for this batch:  0.52
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.15520032
time for this batch:  0.695
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13479383
time for this batch:  0.59
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14922135
time for this batch:  0.64
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.160155
time for this batch:  0.567
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14005847
time for this batch:  0.623
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.13721994
time for this batch:  0.523
-----------------a batch ends---------------
train loss for this epoch:  0.144667
----------------validate-------------------
ave Recall 0.6711372942334051
ave NDCG 0.5689876704894467
----------------test-------------------
ave Recall 0.6553287424027083
ave NDCG 0.5501510096941673
running time for this epoch:  39.95010709762573
running time until now:  1270.0710430145264
-------------------------an epoch ends ---------------------------
i_epoch:  27
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.1360541
time for this batch:  0.685
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.12702301
time for this batch:  0.492
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14590755
time for this batch:  0.466
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14207923
time for this batch:  0.598
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14206403
time for this batch:  0.502
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14705378
time for this batch:  0.584
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.1483244
time for this batch:  0.566
-----------------a batch ends---------------
train loss for this epoch:  0.142243
----------------validate-------------------
ave Recall 0.6691675036552192
ave NDCG 0.5674988482868119
----------------test-------------------
ave Recall 0.6573804013267961
ave NDCG 0.5507505003647395
running time for this epoch:  40.126569986343384
running time until now:  1310.197655916214
-------------------------an epoch ends ---------------------------
i_epoch:  28
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.108726576
time for this batch:  0.528
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.1380427
time for this batch:  0.501
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14398256
time for this batch:  0.552
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.13846067
time for this batch:  0.571
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.12785912
time for this batch:  0.59
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13619703
time for this batch:  0.566
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.12777913
time for this batch:  0.525
-----------------a batch ends---------------
train loss for this epoch:  0.142319
----------------validate-------------------
ave Recall 0.6618795495983054
ave NDCG 0.5631134651188047
----------------test-------------------
ave Recall 0.654684802370557
ave NDCG 0.5475266646462953
running time for this epoch:  39.44021916389465
running time until now:  1349.6379199028015
-------------------------an epoch ends ---------------------------
i_epoch:  29
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.14674035
time for this batch:  0.555
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13186295
time for this batch:  0.459
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.12055136
time for this batch:  0.67
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.13859174
time for this batch:  0.627
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.15253602
time for this batch:  0.487
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.12678784
time for this batch:  0.54
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.13555998
time for this batch:  0.569
-----------------a batch ends---------------
train loss for this epoch:  0.142106
----------------validate-------------------
ave Recall 0.6619104232255076
ave NDCG 0.5607514663058794
----------------test-------------------
ave Recall 0.6603106570400155
ave NDCG 0.5513885578943847
running time for this epoch:  39.72696805000305
running time until now:  1389.3649499416351
-------------------------an epoch ends ---------------------------
i_epoch:  30
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13251773
time for this batch:  0.486
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.15190001
time for this batch:  0.444
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13463533
time for this batch:  0.641
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14969243
time for this batch:  0.513
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.15692963
time for this batch:  0.757
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13182929
time for this batch:  0.555
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.17294207
time for this batch:  0.566
-----------------a batch ends---------------
train loss for this epoch:  0.140803
----------------validate-------------------
ave Recall 0.6670842088799456
ave NDCG 0.5665263660540145
----------------test-------------------
ave Recall 0.6610667145458899
ave NDCG 0.5458345543700606
running time for this epoch:  40.52121138572693
running time until now:  1429.8862085342407
-------------------------an epoch ends ---------------------------
i_epoch:  31
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12785524
time for this batch:  0.516
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.12695447
time for this batch:  0.609
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.15478086
time for this batch:  0.466
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14100564
time for this batch:  0.624
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.12551211
time for this batch:  0.568
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13090712
time for this batch:  0.403
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14700525
time for this batch:  0.594
-----------------a batch ends---------------
train loss for this epoch:  0.140736
----------------validate-------------------
ave Recall 0.660630905852648
ave NDCG 0.5626892241893489
----------------test-------------------
ave Recall 0.6553828496703396
ave NDCG 0.547952909791229
running time for this epoch:  38.858450174331665
running time until now:  1468.7447006702423
-------------------------an epoch ends ---------------------------
i_epoch:  32
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12940061
time for this batch:  0.533
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13392344
time for this batch:  0.573
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14577237
time for this batch:  0.553
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.12902014
time for this batch:  0.661
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13574201
time for this batch:  0.505
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.1487375
time for this batch:  0.664
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.13581535
time for this batch:  0.565
-----------------a batch ends---------------
train loss for this epoch:  0.139244
----------------validate-------------------
ave Recall 0.6630621267800755
ave NDCG 0.5601274225773075
----------------test-------------------
ave Recall 0.6576021713384199
ave NDCG 0.549467224106358
running time for this epoch:  40.35519075393677
running time until now:  1509.0999474525452
-------------------------an epoch ends ---------------------------
i_epoch:  33
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12989861
time for this batch:  0.556
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.1293781
time for this batch:  0.543
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14546546
time for this batch:  0.56
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14309451
time for this batch:  0.639
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.15431295
time for this batch:  0.566
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.15035689
time for this batch:  0.547
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15443158
time for this batch:  0.578
-----------------a batch ends---------------
train loss for this epoch:  0.140152
----------------validate-------------------
ave Recall 0.6630616602196975
ave NDCG 0.5593502608916654
----------------test-------------------
ave Recall 0.6544372534892647
ave NDCG 0.5451691030896997
running time for this epoch:  40.148518323898315
running time until now:  1549.2485058307648
-------------------------an epoch ends ---------------------------
i_epoch:  34
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13550574
time for this batch:  0.552
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14030777
time for this batch:  0.509
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13995162
time for this batch:  0.646
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14487658
time for this batch:  0.665
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.15011999
time for this batch:  0.612
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14523426
time for this batch:  0.557
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14497927
time for this batch:  0.56
-----------------a batch ends---------------
train loss for this epoch:  0.139726
----------------validate-------------------
ave Recall 0.6654834900317698
ave NDCG 0.5633133529850454
----------------test-------------------
ave Recall 0.6591589953034338
ave NDCG 0.5508996633963907
running time for this epoch:  41.33461809158325
running time until now:  1590.5831654071808
-------------------------an epoch ends ---------------------------
i_epoch:  35
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13445243
time for this batch:  0.551
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.123624116
time for this batch:  0.639
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.12945761
time for this batch:  0.669
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14849576
time for this batch:  0.603
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14342225
time for this batch:  0.603
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13473329
time for this batch:  0.588
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.17021266
time for this batch:  0.644
-----------------a batch ends---------------
train loss for this epoch:  0.13981
----------------validate-------------------
ave Recall 0.6680794388592297
ave NDCG 0.5620969186905242
----------------test-------------------
ave Recall 0.6606982043058652
ave NDCG 0.5504689677266366
running time for this epoch:  39.426342725753784
running time until now:  1630.0095512866974
-------------------------an epoch ends ---------------------------
i_epoch:  36
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.11932519
time for this batch:  0.512
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14459945
time for this batch:  0.633
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13542032
time for this batch:  0.638
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.13926902
time for this batch:  0.55
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14496139
time for this batch:  0.743
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13847707
time for this batch:  0.735
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.13928826
time for this batch:  0.608
-----------------a batch ends---------------
train loss for this epoch:  0.139271
----------------validate-------------------
ave Recall 0.670626610810929
ave NDCG 0.5676596927056257
----------------test-------------------
ave Recall 0.6588616387314193
ave NDCG 0.5516059612171412
running time for this epoch:  46.36190605163574
running time until now:  1676.3715267181396
-------------------------an epoch ends ---------------------------
i_epoch:  37
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12839177
time for this batch:  0.53
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14361489
time for this batch:  0.624
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14957994
time for this batch:  0.503
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14547859
time for this batch:  0.589
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14534742
time for this batch:  0.56
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14290059
time for this batch:  0.646
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.13532293
time for this batch:  0.687
-----------------a batch ends---------------
train loss for this epoch:  0.139915
----------------validate-------------------
ave Recall 0.6632720543352449
ave NDCG 0.5651918507363767
----------------test-------------------
ave Recall 0.6556497212997415
ave NDCG 0.5521660496156572
running time for this epoch:  40.33217906951904
running time until now:  1716.7037599086761
-------------------------an epoch ends ---------------------------
i_epoch:  38
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12983808
time for this batch:  0.538
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.1214897
time for this batch:  0.579
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13200806
time for this batch:  0.592
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14788523
time for this batch:  0.544
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.12452458
time for this batch:  0.609
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13644062
time for this batch:  0.51
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14021954
time for this batch:  0.649
-----------------a batch ends---------------
train loss for this epoch:  0.138756
----------------validate-------------------
ave Recall 0.6682659484846877
ave NDCG 0.5686967951068023
----------------test-------------------
ave Recall 0.6623692762954363
ave NDCG 0.5559872264081934
running time for this epoch:  40.151933431625366
running time until now:  1756.8557386398315
-------------------------an epoch ends ---------------------------
i_epoch:  39
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13483903
time for this batch:  0.605
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13430147
time for this batch:  0.603
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14690039
time for this batch:  0.61
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14687814
time for this batch:  0.546
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13890663
time for this batch:  0.577
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13982686
time for this batch:  0.545
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.15139683
time for this batch:  0.589
-----------------a batch ends---------------
train loss for this epoch:  0.138157
----------------validate-------------------
ave Recall 0.6692140525512082
ave NDCG 0.5651113543858903
----------------test-------------------
ave Recall 0.6570730699333696
ave NDCG 0.5535352359581339
running time for this epoch:  39.64781928062439
running time until now:  1796.503597021103
-------------------------an epoch ends ---------------------------
i_epoch:  40
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13922366
time for this batch:  0.56
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.123759516
time for this batch:  0.632
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13762847
time for this batch:  0.568
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.1443252
time for this batch:  0.544
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.15196958
time for this batch:  0.663
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13419628
time for this batch:  0.568
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14300515
time for this batch:  0.59
-----------------a batch ends---------------
train loss for this epoch:  0.137899
----------------validate-------------------
ave Recall 0.6647109969030972
ave NDCG 0.5618287892651335
----------------test-------------------
ave Recall 0.6565224057374752
ave NDCG 0.5487596445142802
running time for this epoch:  40.38740873336792
running time until now:  1836.8910534381866
-------------------------an epoch ends ---------------------------
i_epoch:  41
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.14082624
time for this batch:  0.522
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.12638009
time for this batch:  0.534
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13354862
time for this batch:  0.504
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.13163503
time for this batch:  0.588
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14747249
time for this batch:  0.581
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.1495915
time for this batch:  0.554
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14359984
time for this batch:  0.555
-----------------a batch ends---------------
train loss for this epoch:  0.138723
----------------validate-------------------
ave Recall 0.666693732258637
ave NDCG 0.56351057098177
----------------test-------------------
ave Recall 0.6562953404001033
ave NDCG 0.5503069958272107
running time for this epoch:  40.21188998222351
running time until now:  1877.1029851436615
-------------------------an epoch ends ---------------------------
i_epoch:  42
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12376024
time for this batch:  0.563
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14477673
time for this batch:  0.637
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13704818
time for this batch:  0.706
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.13513847
time for this batch:  0.551
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13708007
time for this batch:  0.627
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13891494
time for this batch:  0.645
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14896026
time for this batch:  0.659
-----------------a batch ends---------------
train loss for this epoch:  0.137605
----------------validate-------------------
ave Recall 0.6664025991454957
ave NDCG 0.5668111738125979
----------------test-------------------
ave Recall 0.6587005651053998
ave NDCG 0.5527854359738259
running time for this epoch:  41.33511805534363
running time until now:  1918.438146829605
-------------------------an epoch ends ---------------------------
i_epoch:  43
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12819181
time for this batch:  0.531
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13074115
time for this batch:  0.606
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.12830491
time for this batch:  0.653
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.12952912
time for this batch:  0.672
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14254141
time for this batch:  0.607
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14346462
time for this batch:  0.531
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.16200036
time for this batch:  0.589
-----------------a batch ends---------------
train loss for this epoch:  0.137687
----------------validate-------------------
ave Recall 0.6630470404989134
ave NDCG 0.5592992225614947
----------------test-------------------
ave Recall 0.6632730654402447
ave NDCG 0.5513531443768734
running time for this epoch:  41.70045590400696
running time until now:  1960.1386585235596
-------------------------an epoch ends ---------------------------
i_epoch:  44
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.14528997
time for this batch:  0.452
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.12926233
time for this batch:  0.533
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.12683114
time for this batch:  0.607
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.12961084
time for this batch:  0.519
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13337283
time for this batch:  0.502
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13243026
time for this batch:  0.579
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14144859
time for this batch:  0.561
-----------------a batch ends---------------
train loss for this epoch:  0.137258
----------------validate-------------------
ave Recall 0.662984459320114
ave NDCG 0.5614655998860686
----------------test-------------------
ave Recall 0.6603163957132367
ave NDCG 0.551528083647776
running time for this epoch:  38.39702606201172
running time until now:  1998.5357251167297
-------------------------an epoch ends ---------------------------
i_epoch:  45
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13794483
time for this batch:  0.502
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.12968834
time for this batch:  0.529
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13389899
time for this batch:  0.57
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.13133503
time for this batch:  0.466
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13422674
time for this batch:  0.599
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14045967
time for this batch:  0.505
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.13222656
time for this batch:  0.562
-----------------a batch ends---------------
train loss for this epoch:  0.137447
----------------validate-------------------
ave Recall 0.6601800501657897
ave NDCG 0.5554427868894534
----------------test-------------------
ave Recall 0.6584309055984731
ave NDCG 0.5490416779134866
running time for this epoch:  38.59090828895569
running time until now:  2037.1266722679138
-------------------------an epoch ends ---------------------------
i_epoch:  46
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12763703
time for this batch:  0.493
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.12121446
time for this batch:  0.588
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14757922
time for this batch:  0.592
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.120964855
time for this batch:  0.564
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14618404
time for this batch:  0.556
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14219949
time for this batch:  0.517
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14544374
time for this batch:  0.581
-----------------a batch ends---------------
train loss for this epoch:  0.135344
----------------validate-------------------
ave Recall 0.6636003722516335
ave NDCG 0.560007973633459
----------------test-------------------
ave Recall 0.6582003599673325
ave NDCG 0.548526073337753
running time for this epoch:  39.242151498794556
running time until now:  2076.3688654899597
-------------------------an epoch ends ---------------------------
i_epoch:  47
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.124436624
time for this batch:  0.488
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.12263261
time for this batch:  0.516
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13085377
time for this batch:  0.528
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14981905
time for this batch:  0.567
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13100395
time for this batch:  0.55
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14178424
time for this batch:  0.563
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14181583
time for this batch:  0.556
-----------------a batch ends---------------
train loss for this epoch:  0.13694
----------------validate-------------------
ave Recall 0.6641940744779634
ave NDCG 0.5617505254620583
----------------test-------------------
ave Recall 0.6636941914706376
ave NDCG 0.5518423505176802
running time for this epoch:  37.95195245742798
running time until now:  2114.320859670639
-------------------------an epoch ends ---------------------------
i_epoch:  48
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13035172
time for this batch:  0.459
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13395604
time for this batch:  0.715
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.1420286
time for this batch:  0.614
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.12198212
time for this batch:  0.644
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.1595994
time for this batch:  0.731
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13038114
time for this batch:  0.667
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.1450738
time for this batch:  0.676
-----------------a batch ends---------------
train loss for this epoch:  0.135889
----------------validate-------------------
ave Recall 0.6668819539850013
ave NDCG 0.5638498452008313
----------------test-------------------
ave Recall 0.660072340334225
ave NDCG 0.5480162863162449
running time for this epoch:  45.01913404464722
running time until now:  2159.3400864601135
-------------------------an epoch ends ---------------------------
i_epoch:  49
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12879771
time for this batch:  0.553
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.11374011
time for this batch:  0.616
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13250712
time for this batch:  0.647
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.13551623
time for this batch:  0.73
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.15268901
time for this batch:  0.629
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14719704
time for this batch:  0.769
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14319399
time for this batch:  0.705
-----------------a batch ends---------------
train loss for this epoch:  0.13458
----------------validate-------------------
ave Recall 0.6652976164074782
ave NDCG 0.5623226630280467
----------------test-------------------
ave Recall 0.6596665110404608
ave NDCG 0.5481764850025386
running time for this epoch:  46.076186418533325
running time until now:  2205.4163489341736
-------------------------an epoch ends ---------------------------
i_epoch:  50
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12128706
time for this batch:  0.576
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.14214903
time for this batch:  0.721
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.1453069
time for this batch:  0.581
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.13721383
time for this batch:  0.712
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13462606
time for this batch:  0.664
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.15094301
time for this batch:  0.679
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14191791
time for this batch:  0.717
-----------------a batch ends---------------
train loss for this epoch:  0.136265
----------------validate-------------------
ave Recall 0.6651040856278116
ave NDCG 0.5629309407042173
----------------test-------------------
ave Recall 0.6562747462839228
ave NDCG 0.547984963688783
running time for this epoch:  45.403640270233154
running time until now:  2250.82004404068
-------------------------an epoch ends ---------------------------
i_epoch:  51
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13834068
time for this batch:  0.541
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.11658387
time for this batch:  0.644
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.137629
time for this batch:  0.596
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.13181731
time for this batch:  0.555
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14666954
time for this batch:  0.554
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14819661
time for this batch:  0.581
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.12785634
time for this batch:  0.594
-----------------a batch ends---------------
train loss for this epoch:  0.135348
----------------validate-------------------
ave Recall 0.6635310177126129
ave NDCG 0.5599302690502902
----------------test-------------------
ave Recall 0.6512762836387803
ave NDCG 0.5446575539922943
running time for this epoch:  40.16793346405029
running time until now:  2290.988022327423
-------------------------an epoch ends ---------------------------
i_epoch:  52
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12352951
time for this batch:  0.557
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.13387659
time for this batch:  0.575
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.14176911
time for this batch:  0.596
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14564312
time for this batch:  0.595
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14237344
time for this batch:  0.575
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14715485
time for this batch:  0.546
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.12503228
time for this batch:  0.541
-----------------a batch ends---------------
train loss for this epoch:  0.135456
----------------validate-------------------
ave Recall 0.6710236371343705
ave NDCG 0.5639712195484345
----------------test-------------------
ave Recall 0.6565912152991519
ave NDCG 0.5485871984050594
running time for this epoch:  38.50493788719177
running time until now:  2329.493020296097
-------------------------an epoch ends ---------------------------
i_epoch:  53
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.13135287
time for this batch:  0.565
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.12864596
time for this batch:  0.616
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.11782284
time for this batch:  0.562
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.12357351
time for this batch:  0.6
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.14221373
time for this batch:  0.5
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.12999628
time for this batch:  0.56
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.1392981
time for this batch:  0.538
-----------------a batch ends---------------
train loss for this epoch:  0.134615
----------------validate-------------------
ave Recall 0.6658152067721393
ave NDCG 0.5628364061453872
----------------test-------------------
ave Recall 0.6536529589615531
ave NDCG 0.5472297082299731
running time for this epoch:  38.56106901168823
running time until now:  2368.054146051407
-------------------------an epoch ends ---------------------------
i_epoch:  54
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.14266475
time for this batch:  0.469
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.1471911
time for this batch:  0.547
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.13503167
time for this batch:  0.602
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.12856317
time for this batch:  0.606
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13872108
time for this batch:  0.588
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.14091322
time for this batch:  0.463
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.14177945
time for this batch:  0.606
-----------------a batch ends---------------
train loss for this epoch:  0.135437
----------------validate-------------------
ave Recall 0.6660425770625117
ave NDCG 0.5587378417354614
----------------test-------------------
ave Recall 0.6541499903291345
ave NDCG 0.5463818892705303
running time for this epoch:  38.51424789428711
running time until now:  2406.5684559345245
-------------------------an epoch ends ---------------------------
i_epoch:  55
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.14755373
time for this batch:  0.458
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.12594685
time for this batch:  0.641
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.12972459
time for this batch:  0.593
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.13294466
time for this batch:  0.494
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.136843
time for this batch:  0.614
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.13152069
time for this batch:  0.557
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.155682
time for this batch:  0.635
-----------------a batch ends---------------
train loss for this epoch:  0.135088
----------------validate-------------------
ave Recall 0.6688781627713193
ave NDCG 0.5636401709847659
----------------test-------------------
ave Recall 0.6562602076356927
ave NDCG 0.5515893589687801
running time for this epoch:  40.810394287109375
running time until now:  2447.3789031505585
-------------------------an epoch ends ---------------------------
i_epoch:  56
----------------an epoch starts-------------------
# batch:  63
i_batch:  0.0
the loss is:  0.12794673
time for this batch:  0.635
-----------------a batch ends---------------
i_batch:  10.0
the loss is:  0.12628987
time for this batch:  0.586
-----------------a batch ends---------------
i_batch:  20.0
the loss is:  0.140342
time for this batch:  0.698
-----------------a batch ends---------------
i_batch:  30.0
the loss is:  0.14384916
time for this batch:  0.629
-----------------a batch ends---------------
i_batch:  40.0
the loss is:  0.13078392
time for this batch:  0.644
-----------------a batch ends---------------
i_batch:  50.0
the loss is:  0.1236812
time for this batch:  0.701
-----------------a batch ends---------------
i_batch:  60.0
the loss is:  0.12708735
time for this batch:  0.569
-----------------a batch ends---------------
train loss for this epoch:  0.133995
----------------validate-------------------
ave Recall 0.6705763035432994
ave NDCG 0.5639828037337589
----------------test-------------------
ave Recall 0.6567230939983371
ave NDCG 0.5511999805398409
Early stop at the 57-th epoch
In [17]:
print ("start preparing for vali and test")
vali_u_v, vali_x_poi, vali_x_user, vali_x_adj, vali_y_real = prepare_validate_test(vali, hyper_param)
test_u_v, test_x_poi, test_x_user, test_x_adj, test_y_real = prepare_validate_test(test, hyper_param)
start preparing for vali and test
In [18]:
#8.4: validate and test the model
print ("---------------validation-------------------")
all_recall, all_ndcg, ave_recall, ave_ndcg, vali_output, vali_real =\
    validate_test(trained_model, hyper_param, vali_u_v, vali_x_poi, vali_x_user, vali_x_adj, vali_y_real, True)
print ("-----------finish model validation---------------")
---------------validation-------------------
ave Recall 0.6705763035432994
ave NDCG 0.5639828037337589
-----------finish model validation---------------
In [19]:
print ("---------------test-------------------")
all_recall, all_ndcg, ave_recall, ave_ndcg, test_output, test_real =\
    validate_test(trained_model, hyper_param, test_u_v, test_x_poi, test_x_user, test_x_adj, test_y_real, True)
print ("-----------finish model validation---------------")
---------------test-------------------
ave Recall 0.6567230939983371
ave NDCG 0.5511999805398409
-----------finish model validation---------------

9: save¶

In [20]:
list_vali_hat = vali_output.cpu().detach().numpy().tolist()
list_vali_real = vali_real.cpu().detach().numpy().tolist()
print(len(list_vali_hat))
print(len(list_vali_hat[0]))
print(len(list_vali_hat[0][0]))
print(len(list_vali_hat[0][0][0]))

list_test_hat = test_output.cpu().detach().numpy().tolist()
list_test_real = test_real.cpu().detach().numpy().tolist()
print(len(list_test_hat))
print(len(list_test_hat[0]))
print(len(list_test_hat[0][0]))
print(len(list_test_hat[0][0][0]))
18
1
1827
80
36
1
1827
80
In [21]:
result = {"vali_hat": list_vali_hat, "vali_real": list_vali_real, \
          "test_hat": list_test_hat, "test_real": list_test_real}

subfile = case+'/vali_predict.json'
savefile = open(subfile,'w')
json.dump(result, savefile)
savefile.close()

df = json.load(open(subfile))
df.keys()
print(len(df["test_real"]))
36
In [ ]: